iT邦幫忙

2026 iThome 鐵人賽

DAY 20
0
AI Engineering

GPU很忙?他真的有在做事嗎?系列 第 20

Day 20|誰在拖慢 LLM 多卡訓練?straggler 的視覺特徵

  • 分享至 

  • xImage
  •  

Day 19 把 NCCL overlap 拆開後,還有一個問題沒回答:同一筆 collective 裡,各個 rank 是一起到,還是有人先到、有人晚到?

可以把 collective 想成八個人約在同一個集合點。早到的人要等,最後一個人到了之後,大家才一起往下走。放到 GPU timeline 上,先到的 rank 可能在 NCCL kernel 裡等其他人,最後到的 rank 反而幾乎不用等。結果就有點反直覺:kernel 最長的卡,可能只是等最久,不一定是拖慢大家的人。

這也是為什麼 message size ÷ duration 只能算應用層的有效速率,不能直接當成鏈路利用率。今天不再看七張卡各自的總帳,而是把同一筆 collective 橫向排在一起,看看誰先到、誰最後到,以及晚開始的原因到底在 CPU 還是 GPU。

今天要處理三件事:

  1. 從 timeline 上怎麼認出 collective 的 late arriver(最後抵達者)?
  2. 主檔 A 是固定同一張卡落後,還是每次換人?
  3. 開始時間的落差來自 CPU 太晚送出 CUDA launch,還是 GPU 端的依賴與排程?

本文沿用主檔 A 的 sample_0(repeat=5),分析範圍是 39.964–46.123 秒,工具版本為 nsys-ai v0.3.0-21-g1cc03b5。這是八卡作業,但 GPU kernel timeline 只錄到 device 1–7,因此跨卡結論只涵蓋這七張;缺少的 device 0 仍可能改變完整八卡的先後順序。

然後另外,本文說的 straggler,指的是「某一筆 collective 最後抵達的 rank」。它比較像一次集合遲到,不代表那張 GPU 永久故障,也不代表整段訓練都由它拖慢。

先看 nccl_anomaly 找到什麼

先用 nccl_anomaly 找出 duration 明顯高於同類平均的 NCCL kernel:

nsys-ai skill run nccl_anomaly megatron.sqlite \
  --trim 39.964 46.123
── NCCL Anomalies ──
Op Type            Duration        Avg   Ratio  Stream
──────────────────────────────────────────────────────
ReduceScatter      59.091ms    7.388ms    8.0×      56
ReduceScatter      59.074ms    7.388ms    8.0×      56
ReduceScatter      59.073ms    7.388ms    8.0×      56
ReduceScatter      59.070ms    7.388ms    8.0×      56
ReduceScatter      59.065ms    7.388ms    8.0×      56
ReduceScatter      59.059ms    7.388ms    8.0×      56
AllGather          57.439ms    7.942ms    7.2×      56
...

表格很醒目,但還不能直接說「找到 20 次 straggler」。這裡有兩個細節。

第一,前六筆 ReduceScatter 的 duration 幾乎一樣,差不到 0.04 ms。比起六個互不相關的異常,它更像是同一筆 collective 在六張卡上留下的六個等待視角。

第二,這版工具預設只回傳最慢的 20 列,最後顯示的 630 total ops 又是第一列所屬的 ReduceScatter 總數,不是整份 profile 的 NCCL 總數。因此,不能把畫面上的「20」直接解讀成 20 個獨立事件。把 limit 放大後,門檻以上共有 37 列 kernel;真正要知道有幾次跨卡事件,仍得先把同一筆 collective 配對。

逐筆配對:先確認序列真的一致

主檔 A 的 device 1–7,在 stream 56 都有 225 筆 collective:

AllGather:      135 筆
ReduceScatter:   90 筆
合計:          225 筆/device

我先把每張卡的 collective 依開始時間排序,再逐位比較類型。225 個位置全部一致,沒有任何一張多一筆、少一筆或順序不同,這才允許把七張卡的「第 k 筆」排在同一列。

只靠順序仍不是萬無一失;如果不同卡剛好各漏掉同類型的事件,序列還是可能看起來一樣。因此還要做第二個檢查:配對後的結束時間是否集中。結果很明顯:

結束時間的跨卡差距:p50 0.052 ms、p90 0.086 ms、最大 0.118 ms
開始時間的跨卡差距:p50 0.441 ms、p90 10.426 ms、最大 53.234 ms

結束時間幾乎對齊,開始時間卻能差到 53 ms。除了再次確認配對合理,這組數字也把 late arriver 的樣子畫得很清楚:同一筆 collective 不一定一起開始,但會在很接近的時間完成。

NCCL 的 device primitive 會在 GPU kernel 內等待 peer 的連線進度或資料就緒;不同 protocol 的細節不一樣,所以這裡不因為 kernel symbol 帶有 _LL 就認定實際一定走 LL。比較安全的說法是:

觀測到的 NCCL kernel duration
≈ 等待其他 rank 的時間 + 實際傳輸與歸約時間

以開始差距最大的第 200 筆(從 1 起算)為例,這是一筆 ReduceScatter:

  • 六張先到的卡,kernel duration 為 57–59 ms。
  • device 4 晚了 53.2 ms 才開始,duration 只有 5.8 ms。
  • 七張卡的結束時間仍落在 0.1 ms 內。

把它畫成七條橫線後,方向就清楚了:這一筆裡,長 kernel 是先到後等待的 rank;短 kernel 才是最後抵達者。OSDI 2025 的大規模訓練研究也用相同現象分析 TP communication:不同 rank 的 kernel 開始時間不一樣,結束時間卻大致對齊,再從開始落差往上游追原因。

但別把這句話推成通則。若某張卡本身的網路路徑較慢、傳輸量不同,或同時有多個 rank 出問題,最長 duration 仍可能有其他意義。先比較同一筆 collective 的 start/end,再判斷誰在等誰;不要只靠總 duration 排名。

同一筆 ReduceScatter 在七張卡上的實測:六張卡較早開始、duration 為 57 到 59 ms;device 4 晚了 53.2 ms 才開始,duration 只有 5.8 ms,但七張卡仍在 0.1 ms 內完成

有沒有固定同一張卡最後到?

對 225 筆 collective 逐一記錄最早與最晚開始的 device:

device 最後開始次數 最早開始次數
1 74 30
2 35 10
3 21 15
4 47 20
5 11 61
6 9 65
7 28 24

乍看之下,device 1 最可疑:它最後開始 74 次,device 4 則是 47 次;device 5、6 最常排在前面。不過,「最後開始次數」只看名次,不看差多少。把開始差距超過 20 ms 的八次事件排除後,各卡平均只比當次最早者晚 0.8–1.4 ms。多數時候只是毫秒級時差,不能因為 device 1 拿了 74 次最後一名,就直接叫它壞卡。

stream 56 的 NCCL kernel 總時間也沒有和名次完全一一對應:

device stream 56 NCCL kernel time
1 1,689.9 ms
2 1,681.5 ms
3 1,753.3 ms
4 1,774.0 ms
5 1,813.3 ms
6 1,750.9 ms
7 1,764.8 ms

常常晚到的 device 1、2 確實累積了比較短的 NCCL duration,符合「等得少」的方向;但 device 4 並不是 NCCL 時間最短的卡。這也修正前兩天容易混在一起的兩個數字:device 4 的 1,094.7 ms 是 NCCL-only 時間,完整 NCCL kernel duration 其實是 1,803.9 ms。前者還會受到它和其他 GPU kernel 重疊位置的影響,不能只用遲到次數解釋。

換句話說,這幾張表回答的是不同問題。Day 19 的 device 4 overlap 最高,只能說它的 NCCL 有較高比例與其他 GPU kernel 同時執行;不能反推「它一定是拖慢大家的那張」。要找 late arriver,最直接的做法仍是把同一筆 collective 的開始與結束時間排在一起。

stream 56 的 225 筆 collective 逐筆比較:device 1 與 4 最常最後開始,device 5 與 6 最常最早開始,但沒有固定同一張卡包辦遲到;下半部用跨卡最短 duration 當基線,估算 start skew 占七卡 NCCL kernel time 的 28.3%

28.3% 是 start-skew 估計,不是 step slowdown

知道誰先到、誰晚到之後,下一個自然的問題是:這些時差累積起來有多大?本文採用一個簡化算法:同一筆 collective 取七張卡最短的 kernel duration 當傳輸基線,其餘 duration 超過基線的部分視為 start-skew 成本。

這和 AMD TraceLens 的 collective report 口徑相同:它以跨 ranks 的最短 duration 當 comm_latency,再把晚到造成的差異列為 wait time/start skew。OSDI 2025 的研究則以「共同的最晚開始時間到結束時間」估 transfer duration;在主檔 A 這種結束時間對齊到 0.12 ms 內的情況,兩種估法很接近。

主檔 A 的 stream 56 七卡合計如下:

七卡 NCCL kernel time:                   12,227.7 ms
基線:每筆最短 duration × 7 卡:           8,765.0 ms
相對基線多出的 duration:                  3,462.7 ms
相對占比:                                    28.3%

這個 28.3% 應該叫做 start-skew estimate,而不是絕對精準的「等待時間」。它有三個限制:

  1. 最短 duration 仍可能包含少量等待,或受到不同 GPU 排程與傳輸路徑影響。
  2. device 0 沒有 GPU trace,完整八卡的最晚開始者與最短 duration 可能不同。
  3. 12,227.7 ms 是七張卡 kernel duration 的加總,不是 6.16 秒視窗的 wall time;其中不少等待和其他 GPU kernel 重疊,28.3% 更不是 step 可以直接縮短的比例。

所以這個數字比較像「同步時差的溫度計」,不是可以直接從 step time 扣掉的預算。不過,它仍然很適合拿來看問題的形狀。把 3,462.7 ms 再拆一次:

開始差距 > 20 ms:  8 筆跨卡事件,約 1,854.6 ms
其餘事件:         217 筆跨卡事件,約 1,608.1 ms

八次大時差貢獻約 53.6%,其餘 217 次毫秒級差異合計約 46.4%。前者適合逐筆追 timeline,後者比較像長期排程與負載的穩定偏差,兩種問題不該混成同一個平均數處理。

也因為 Day 19 已經發現 communicator 次數對不攏,這裡不再拿最短 duration 和 900 GB/s 規格硬算「NVLink 使用率」。要判斷真正的傳輸效率,仍要先確認 communicator、message size、algorithm/protocol,再和同拓撲的 nccl-tests baseline 比較。

八次大時差:位置固定,但不是 CPU 晚呼叫

把開始差距超過 20 ms 的八筆 collective 放回五個 step:

collective 步內位置 發生次數 最後開始的 device
AllGather 約 +460 ms 5/5 steps dev2、dev2、dev2、dev3、dev1
ReduceScatter 約 +518 ms 3/5 steps dev1、dev6、dev4

這張地圖很有辨識度:事件的位置固定,最後開始的卡卻一直換人。光看到這裡,很容易猜成某個 rank 的 Python、GC 或 CPU 排程偶爾停了約 50 ms;原稿也是這樣判斷。不過把 NCCL kernel 接回 CUDA runtime 後,故事不是這樣。

以 process ID 與 correlationId 配對後,這八筆 NCCL 的 cuLaunchKernelEx 都在 GPU kernel 真正開始前 236–297 ms 就已經完成。也就是說,CPU 早已把工作放進 CUDA 排程,並不是到了 +460/+518 ms 才臨時呼叫 NCCL。

GPU timeline 也顯示,最後抵達的 collective 都貼著 stream 21 上某個 GEMM 的尾端才開始:

collective NCCL stream 同時段的 GEMM 最後抵達 rank 上的 GEMM duration
AllGather 56 nvjet_tst_128x320_64x3_2x1_v_bz_coopB_NNN 47.7–48.9 ms
ReduceScatter 56 nvjet_tst_192x192_64x3_2x1_v_bz_coopB_NTN 50.0–52.7 ms

把七張卡並排後,線索更明顯。在較早抵達的卡上,NCCL 會和這些 GEMM 重疊;在最後抵達的卡上,NCCL 則接近 GEMM 結束時才被排進 GPU。這比較像跨 stream 的 event dependency、CUDA hardware queue 對映,或 GEMM/NCCL 資源競爭造成的排程差異。只靠現有 trace 還無法分辨是哪一種,但至少可以排除「這八次都是 CPU 太晚呼叫 NCCL」。

OSDI 2025 的研究也記錄過 false kernel dependency:本來沒有資料相依的 kernel 因為共用 CUDA hardware queue 而互相阻塞,調整 CUDA_DEVICE_MAX_CONNECTIONS 後改善。不過這只能當 A/B test 的方向,不能直接套用成主檔 A 的診斷。

固定位置、裝置輪替也不太像某一張 GPU 持續降頻;GREYHOUND 的熱降頻案例是固定同一張 GPU 長期慢約兩成。可是主檔 A 只有五步、又缺 device 0,還不能據此宣布硬體完全健康。比較合理的優先順序是:先查這兩個固定位置的依賴與排程,同時保留 clock、溫度與 power throttle telemetry 來排除硬體問題。

五個 step 的大時差地圖:AllGather 每步約加 460 ms、ReduceScatter 在三步約加 518 ms 才出現明顯 start skew;CUDA runtime 顯示 collective 早已送進排程,GPU start 則貼著兩種 GEMM 的尾端,應優先檢查跨 stream 依賴與 GPU 排程

下一次錄 profile,要補哪些證據?

查到這裡,嫌疑範圍已經從「不知道哪張卡慢」縮到兩個固定位置、兩種 GEMM,以及 GPU 排程。現有 profile 還看不出 CUDA stream 到底在等哪個 event,也沒有 CPU sampling、context switch 與完整 Python call stack。下一輪可以分四條線補資料:

  • CUDA stream 與 queue:在 Nsight Systems 裡保留 CUDA API、CUDA Graph、NVTX 與 GPU context-switch 資訊,把 +460/+518 ms 前的 cudaStreamWaitEvent、event record 和 graph node 接起來;再對 CUDA_DEVICE_MAX_CONNECTIONS 做受控 A/B test。
  • collective 身分:PyTorch flight recorder 搭配 TORCH_NCCL_TRACE_BUFFER_SIZETORCH_NCCL_ENABLE_TIMINGTORCH_NCCL_TRACE_CPP_STACK,補 process group、sequence number 與 C++ call stack。
  • NCCL 選路:用 NCCL_DEBUG=INFONCCL_DEBUG_SUBSYS=INIT,GRAPH,TUNING 確認拓撲、algorithm 與 protocol,避免只憑 kernel symbol 猜設定。
  • 硬體健康:訓練期間持續記錄 clock、溫度、功耗,以及 nvidia-smi 的 Clocks Event Reasons counters;只看某一瞬間的 Not Active 可能漏掉短暫降頻。

Python GC 仍是多卡訓練常見的抖動來源。OSDI 2025 的案例觀察到不同 workers 會在不同 step 觸發 GC,Megatron-LM 也提供 --manual-gc--manual-gc-interval。但對主檔 A 這八次事件來說,collective 的 CUDA launch 已經提早送出,所以 GC 不該排在目前的第一順位。

四個容易踩到的坑

第一,把 NCCL kernel 最長的卡直接叫做 straggler。在「開始不齊、結束對齊」的型態裡,長 kernel 通常是先到後等待的 rank。要看的是同一筆 collective 的開始與結束,不是跨整段 profile 排總時間。

第二,把 anomaly 表格的 20 列當成 20 次事件。工具預設只回傳最慢 20 列,而且同一筆 collective 會在多張卡上各留一列;先跨卡分組,才能數真正的事件。

第三,看到 GPU kernel 晚開始,就認定 CPU 晚發射。主檔 A 的八次大時差裡,CUDA launch 早在 236–297 ms 前完成。GPU start 還會受 stream event、hardware queue 與資源排程影響,必須把 runtime 與 kernel correlation 接起來。

第四,把 28.3% 當成 step slowdown。它是七卡 stream 56 的 kernel-duration skew estimate,既是跨卡加總,也可能與其他 GPU 工作重疊;不能直接從 step time 扣掉。

小結與明天

今天把主檔 A 的 225 筆 stream 56 collective 逐筆對齊。最明顯的視覺特徵是:結束時間的 p50 差距只有 0.052 ms,開始時間的 p50 是 0.441 ms、最大卻到 53.234 ms。以跨卡最短 duration 當基線,start skew 約占七卡 NCCL kernel time 的 28.3%;其中一半集中在八次固定位置的大時差,另一半來自 217 次毫秒級差異。

這五步內沒有固定同一張卡包辦最後抵達,更重要的是,八次大時差的 NCCL launch 都早已由 CPU 送出,GPU kernel 卻在兩種 GEMM 尾端才開始。現在最值得追的是跨 stream 依賴、hardware queue 與資源競爭,而不是先怪 Python GC 或直接換卡。

Part D 的多卡三部曲到這裡收齊:Day 18 拆 collective 組成,Day 19 拆 overlap,今天拆跨 rank 的 start skew。明天換到 kernel 內部:Nsight Systems 已經指出可疑位置,接下來用 Nsight Compute 看單一 kernel 為什麼跑成現在這個樣子。

參考資料


上一篇
Day 19|訓練 LLM 的通訊成本藏得好嗎?拆解 NCCL overlap
下一篇
Day 21|kernel 為什麼慢?nsys 點名之後,換 Nsight Compute 臨檢
系列文
GPU很忙?他真的有在做事嗎?21
圖片
  熱門推薦
圖片
{{ item.channelVendor }} | {{ item.webinarstarted }} |
{{ formatDate(item.duration) }}
直播中

尚未有邦友留言

立即登入留言